Added instrumentation for netfx SqlClient. #761

CodeBlanch · 2020-07-02T01:50:52Z

Changes

Adds an ActivitySource for .NET Framework SqlClient BeginExecute/EndExecute events which are captured through SqlEventSource. The EventSource emits just enough information to provide similar data to what we have for .NET Core instrumentation.

Differences:

CommandText when CommandType = Text is not available. CommandText when CommandType = StoredProcedure is available. Code is here.
Exception message is not available. We only get sqlExceptionNumber. Code is here.

Open to suggestions on how to unit test in some useful way. I did use an actual SqlServer to make sure it worked.

Microsoft folks: What I can see as far as reference source is limited. Do you guys have access to see how far back this SqlEventSource has existed? I made the code fail gracefully if it isn't found, but it would be nice to know supported versions.

Checklist

I ran Unit Tests locally.

CodeBlanch · 2020-07-02T01:52:23Z

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlClientDiagnosticListener.cs

@@ -91,11 +90,10 @@ public override void OnCustom(string name, Activity activity, object payload)

                            if (this.commandTypeFetcher.Fetch(command) is CommandType commandType)
                            {
-                                activity.AddTag(DatabaseStatementTypeSpanAttributeKey, commandType.ToString());


This change was made to avoid the .ToString perf hit. Unrelated to the main changes, sorry.

:D I read this comment late, and was still trying to figure out this part !

cijothomas · 2020-07-02T06:37:50Z

Open to suggestions on how to unit test in some useful way. I did use an actual SqlServer to make sure it worked.

Microsoft folks: What I can see as far as reference source is limited. Do you guys have access to see how far back this SqlEventSource has existed? I made the code fail gracefully if it isn't found, but it would be nice to know supported versions.

Happy to see this PR! I remember doing code review when EventSource was added to SqlClient several years back.
Since we only support net452 and above, I think we are good. I can try to find the history, but its available for sure in net452.

cijothomas · 2020-07-02T06:42:19Z

Testing in ApplicationInsights for SqlEventSource:
https://github.com/microsoft/ApplicationInsights-dotnet/blob/develop/WEB/Src/DependencyCollector/DependencyCollector.Tests/Implementation/FrameworkSqlProcessingTest.cs

We can do something similar as the minimum testing.
I don't know of the best way to test this other than spinning up SQL Server inside Docker image and test.
(https://github.com/microsoft/ApplicationInsights-dotnet/blob/develop/WEB/Test/E2ETests/E2ETests/docker-compose452AppOn462.yml#L37)
We don't have an infra yet to spin up container and test. This is something I hope to get sometime after beta release.

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlEventSourceListener.netfx.cs

cijothomas · 2020-07-02T06:53:43Z

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlEventSourceListener.netfx.cs

+                    activity.AddTag(SpanAttributeConstants.PeerServiceKey, (string)eventData.Payload[1]);
+                    activity.AddTag(SpanAttributeConstants.DatabaseInstanceKey, (string)eventData.Payload[2]);
+
+                    if (string.IsNullOrEmpty((string)eventData.Payload[3]))


will this throw if Payload has less than 4 count? Lets do a safety check to ensure payload[3] is fine. (some old version did not provide all the payload , maybe irrelevant now, but lets be on defensive side)

I added some defensive checks. Now validates for payload being null, payload not being the expected size. Doesn't validate the types of the payload so casts could blow up. But that seemed like taking it a step too far? LMK

cijothomas · 2020-07-02T06:56:41Z

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlEventSourceListener.netfx.cs

+
+        private static readonly Version Version = typeof(SqlEventSourceListener).Assembly.GetName().Version;
+        private static readonly ActivitySource SqlClientActivitySource = new ActivitySource(ActivitySourceName, Version.ToString());
+        private static readonly EventSource SqlEventSource = (EventSource)typeof(SqlConnection).Assembly.GetType("System.Data.SqlEventSource")?.GetField("Log", BindingFlags.Static | BindingFlags.NonPublic)?.GetValue(null);


if we make a EventSource writer (i.e FakeSql : EventSource) which mimics the SqlClient event, we could unit test, right? (similar to unit tests firing DiagnosticSource events?)

@cijothomas I'll investigate this docker thing a bit. If it's quick to get up and running that would be great. Otherwise, I'll add some "faked" tests.

Okay.
cc: @TimothyMothra as he'd be looking at adding E2E test pipeline soon.

I tried to get integration tests up and running on docker but ran into a problem. This is .NET Framework specific code, so we need a Windows container. That's not supported on GitHub at the moment, from what I can tell (ref). In the end, I did two things:

Added integration tests that will skip unless an environment variable is set.

Added fake event source tests. That gives us the same level of testing as the other Sql stuff.

I did get pretty far into getting the container up and running. What I would like to do is complete this PR, and then I can try to get Sql integration tests up and running for our .NET Core stuff? I think that will work because there are SQL Linux images and of course .NET Core SDK Linux images.

cijothomas · 2020-07-02T07:10:34Z

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlEventSourceListener.netfx.cs

+                var activity = Activity.Current;
+                if (activity == null || activity.Source != SqlClientActivitySource)
+                {
+                    return;


we dont ever expect to this condition right? I'd suggest to add a Warning/Error log.

Wouldn't this happen for samplers that return ActivityDataRequest.None which would result in no Activity being created? In that case Begin & End events would still fire, but Activity would be null.

Yes you are right. This part is still not expected - activity.Source != SqlClientActivitySource ?

In my mind, it's expected. That case would be, sampler returned ActivityDataRequest.None for our Sql activity but there is some other parent Activity running. It could be any Activity, really. Some parent that was sampled, and the child was None, or it could be some random Activity not run through a sampler at all. Something like this:

Activity myActivity = new Activity("Call SQL user activity"); myActivity.Start(); try { using (SqlConnection connection = new SqlConnection("Data Source=sqlserver;Initial Catalog=master;Integrated Security=True;")) { connection.Open(); using (SqlCommand command = new SqlCommand("select 1/1", connection)) { command.ExecuteNonQuery(); } } } catch { } myActivity.Stop(); Log.LogActivity(myActivity);

In that case, when EndExecute fires Activity.Current will be non-null! The activity.Source == SqlClientActivitySource check is to make sure it is actually our activity so we don't stop/tag something that doesn't belong to us.

Perfect! thanks for clarifying.

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlEventSourceListener.netfx.cs

eddynaka · 2020-07-02T10:36:37Z

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlClientDiagnosticListener.cs

                                switch (commandType)
                                {
                                    case CommandType.StoredProcedure:
+                                        activity.AddTag(DatabaseStatementTypeSpanAttributeKey, "StoredProcedure");


Instead of using the magic string "StoredProcedure", i would use nameof(commandtype) or nameof(CommandType.StoredProcedure). The same comment applys for "Text" / "TableDirect"

https://github.com/open-telemetry/opentelemetry-specification/blob/master/specification/trace/semantic_conventions/database.md Nothing here about "Type"! should we raise an issue to add it to spec?

@eddynaka What you have against magic? j/k I added the nameof part in both Sql instrumentation classes.

@cijothomas I'll open an issue in spec for db.statement_type but my success rate there so far has been 0 😭 Maybe we should name it db.mssql.statement_type? Looking at the guide, what's interesting is that a lot of the database semantics have changed since I last worked on this instrumentation. I updated them on this PR:

db.type is now db.system and we send mssql instead of sql.

db.instance is now db.name.

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlClientDiagnosticListener.cs

vhatsura · 2020-07-02T11:20:05Z

We don't have an infra yet to spin up container and test. This is something I hope to get sometime after beta release.

I suggest looking into https://github.com/Deffiss/testenvironment-docker. It allow to bootstrap docker containers directly from code in unit tests setup and use it later in your tests.

cijothomas · 2020-07-02T17:00:39Z

We don't have an infra yet to spin up container and test. This is something I hope to get sometime after beta release.

I suggest looking into https://github.com/Deffiss/testenvironment-docker. It allow to bootstrap docker containers directly from code in unit tests setup and use it later in your tests.

Thanks. Do you know if this unit test can be run in GH Actions?

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlEventSourceListener.netfx.cs

src/OpenTelemetry.Exporter.Jaeger/Implementation/JaegerActivityExtensions.cs

OpenTelemetry.sln

cijothomas · 2020-07-07T05:13:32Z

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlEventSourceListener.netfx.cs

+
+            if (activity.IsAllDataRequested)
+            {
+                activity.AddTag(SpanAttributeConstants.ComponentKey, "sql");


note to myself.
component is removed from spec and we need to remove it from this repo.

cijothomas · 2020-07-07T05:17:50Z

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlEventSourceListener.netfx.cs

+                return;
+            }
+
+            string databaseName = (string)eventData.Payload[2];


wondering why setting displayname is not inside if (activity.IsAllDataRequested) ?

I modeled after the HttpWebRequestActivitySource:

opentelemetry-dotnet/src/OpenTelemetry.Instrumentation.Dependencies/Implementation/HttpWebRequestActivitySource.netfx.cs

Lines 94 to 110 in ca322b3

private static void AddRequestTagsAndInstrumentRequest(HttpWebRequest request, Activity activity)

{

activity.DisplayName = HttpTagHelper.GetOperationNameForHttpMethod(request.Method);

InstrumentRequest(request, activity);

activity.SetCustomProperty("HttpWebRequest.Request", request);

if (activity.IsAllDataRequested)

{

activity.AddTag(SpanAttributeConstants.ComponentKey, "http");

activity.AddTag(SpanAttributeConstants.HttpMethodKey, request.Method);

activity.AddTag(SpanAttributeConstants.HttpHostKey, HttpTagHelper.GetHostTagValueFromRequestUri(request.RequestUri));

activity.AddTag(SpanAttributeConstants.HttpUrlKey, request.RequestUri.OriginalString);

activity.AddTag(SpanAttributeConstants.HttpFlavorKey, HttpTagHelper.GetFlavorTagValueFromProtocolVersion(request.ProtocolVersion));

}

}

Line 96 in that snippet.

I did it there originally because the DisplayName felt useful to have always? Open to change it.

Got. I couldn't find any guidelines on this, so at this points, its up to individual library authors to do it. (in case adapters "we" are the authors).

cijothomas · 2020-07-07T05:25:20Z

test/OpenTelemetry.Instrumentation.Dependencies.Tests/SqlEventSourceTests.netfx.cs

+
+            string dataSource = null;
+
+            using (var activityListener = new ActivityListener


why do we need this listener here?

Good catch, we don't need it. I removed from here and the tests that I copied from.

cijothomas · 2020-07-07T05:27:54Z

test/OpenTelemetry.Instrumentation.Dependencies.Tests/SqlEventSourceTests.netfx.cs

+{
+    public class SqlEventSourceTests
+    {
+        /*


Excellent! thanks for commenting the instructions here.

cijothomas · 2020-07-07T05:28:13Z

src/OpenTelemetry.Api/Trace/SpanAttributeConstants.cs

        public const string DatabaseStatementKey = "db.statement";
+        public const string DatabaseStatementTypeKey = "db.statement_type";


Is this part of spec?

Oh I now recollect we already discussed this. Will need to follow up on spec. Note to myself!

cijothomas · 2020-07-07T05:28:49Z

src/OpenTelemetry.Api/Trace/SpanAttributeConstants.cs

@@ -40,9 +40,10 @@ public static class SpanAttributeConstants
        public const string HttpRouteKey = "http.route";
        public const string HttpFlavorKey = "http.flavor";

-        public const string DatabaseTypeKey = "db.type";
-        public const string DatabaseInstanceKey = "db.instance";
+        public const string DatabaseSystemKey = "db.system";


can you add this if feasible?
https://github.com/open-telemetry/opentelemetry-specification/blob/master/specification/trace/semantic_conventions/database.md#connection-level-attributes-for-specific-technologies

Created #782 for this.

cijothomas

left couple comments.
Also there is a merge conflict. Can you take a look at that?

codecov · 2020-07-07T15:00:38Z

Codecov Report

Merging #761 into master will decrease coverage by 1.53%.
The diff coverage is 19.04%.

@@            Coverage Diff             @@
##           master     #761      +/-   ##
==========================================
- Coverage   72.55%   71.01%   -1.54%     
==========================================
  Files         223      223              
  Lines        7002     7007       +5     
  Branches     1181     1180       -1     
==========================================
- Hits         5080     4976     -104     
- Misses       1606     1714     +108     
- Partials      316      317       +1

Impacted Files	Coverage Δ
src/OpenTelemetry.Api/Trace/SpanExtensions.cs	`0.00% <0.00%> (ø)`
....Jaeger/Implementation/JaegerActivityExtensions.cs	`88.98% <0.00%> (ø)`
...tation.AspNet.Win/Implementation/HttpInListener.cs	`0.00% <0.00%> (-85.19%)`	⬇️
...tation.AspNetCore/Implementation/HttpInListener.cs	`77.50% <0.00%> (ø)`
...ies/Implementation/GrpcClientDiagnosticListener.cs	`80.00% <0.00%> (ø)`
...es/Implementation/HttpHandlerDiagnosticListener.cs	`63.76% <0.00%> (ø)`
...ion.Dependencies/OpenTelemetryBuilderExtensions.cs	`56.66% <ø> (ø)`
...mentation.Dependencies/SqlClientInstrumentation.cs	`72.72% <ø> (ø)`
...etry/Instrumentation/InstrumentationEventSource.cs	`15.15% <0.00%> (-0.98%)`	⬇️
...cies/Implementation/SqlClientDiagnosticListener.cs	`78.00% <50.00%> (-4.98%)`	⬇️
... and 8 more

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update cdf0cbe...e9ac05e. Read the comment docs.

cijothomas · 2020-07-07T15:27:40Z

test/OpenTelemetry.Instrumentation.Dependencies.Tests/HttpWebRequestTests.Basic.netfx.cs

-                using var c = new HttpClient();
-                await c.SendAsync(request);
-            }
+            using var c = new HttpClient();


Thanks for cleanup!

Added instrumentation for netfx SqlClient.

06978ba

CodeBlanch requested a review from a team July 2, 2020 01:50

CodeBlanch commented Jul 2, 2020

View reviewed changes

cijothomas reviewed Jul 2, 2020

View reviewed changes

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlEventSourceListener.netfx.cs Outdated Show resolved Hide resolved

cijothomas reviewed Jul 2, 2020

View reviewed changes

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlEventSourceListener.netfx.cs Outdated Show resolved Hide resolved

cijothomas reviewed Jul 2, 2020

View reviewed changes

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlEventSourceListener.netfx.cs Outdated Show resolved Hide resolved

eddynaka reviewed Jul 2, 2020

View reviewed changes

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlClientDiagnosticListener.cs Outdated Show resolved Hide resolved

cijothomas reviewed Jul 2, 2020

View reviewed changes

src/OpenTelemetry.Instrumentation.Dependencies/Implementation/SqlEventSourceListener.netfx.cs Outdated Show resolved Hide resolved

CodeBlanch added 2 commits July 2, 2020 11:07

Code review.

40dd3b1

Send "db.statement_type" instead of "db.statementType".

fb25ff8

CodeBlanch commented Jul 2, 2020

View reviewed changes

src/OpenTelemetry.Exporter.Jaeger/Implementation/JaegerActivityExtensions.cs Show resolved Hide resolved

CodeBlanch added 5 commits July 2, 2020 23:29

Added integration tests for SqlEventSource.

401f740

Merge branch 'master' into netfx-sqlclient-instrumentation

dade046

Adding .github folder to solution.

baa5f1b

Added a couple missing files into the solution.

14c399d

Added FakeSqlEventSource tests.

c3a499c

eddynaka reviewed Jul 3, 2020

View reviewed changes

OpenTelemetry.sln Show resolved Hide resolved

cijothomas reviewed Jul 7, 2020

View reviewed changes

cijothomas requested changes Jul 7, 2020

View reviewed changes

CodeBlanch added 2 commits July 7, 2020 07:49

Merging latest from master.

83200ea

Fixed up GrpcClientDiagnosticListener for EventSource changes.

7e62d1b

Removed extra ActivityListener from unit tests.

b9908b8

cijothomas reviewed Jul 7, 2020

View reviewed changes

Merge branch 'master' into netfx-sqlclient-instrumentation

e9ac05e

cijothomas approved these changes Jul 7, 2020

View reviewed changes

cijothomas merged commit a48ff18 into open-telemetry:master Jul 7, 2020

CodeBlanch deleted the netfx-sqlclient-instrumentation branch July 8, 2020 00:42

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Added instrumentation for netfx SqlClient. #761

Added instrumentation for netfx SqlClient. #761

CodeBlanch commented Jul 2, 2020

CodeBlanch Jul 2, 2020

cijothomas Jul 2, 2020

cijothomas commented Jul 2, 2020

cijothomas commented Jul 2, 2020

cijothomas Jul 2, 2020

CodeBlanch Jul 2, 2020

cijothomas Jul 2, 2020

CodeBlanch Jul 2, 2020

cijothomas Jul 2, 2020

CodeBlanch Jul 3, 2020

cijothomas Jul 2, 2020

CodeBlanch Jul 2, 2020

cijothomas Jul 2, 2020

CodeBlanch Jul 2, 2020

cijothomas Jul 6, 2020

eddynaka Jul 2, 2020 •

edited

Loading

cijothomas Jul 2, 2020

CodeBlanch Jul 2, 2020

vhatsura commented Jul 2, 2020

cijothomas commented Jul 2, 2020

cijothomas Jul 7, 2020

cijothomas Jul 7, 2020

CodeBlanch Jul 7, 2020

cijothomas Jul 7, 2020

cijothomas Jul 7, 2020

CodeBlanch Jul 7, 2020

cijothomas Jul 7, 2020

cijothomas Jul 7, 2020

cijothomas Jul 7, 2020

cijothomas Jul 7, 2020

CodeBlanch Jul 8, 2020

cijothomas left a comment

codecov bot commented Jul 7, 2020 •

edited

Loading

cijothomas Jul 7, 2020

	private static void AddRequestTagsAndInstrumentRequest(HttpWebRequest request, Activity activity)
	{
	activity.DisplayName = HttpTagHelper.GetOperationNameForHttpMethod(request.Method);

	InstrumentRequest(request, activity);

	activity.SetCustomProperty("HttpWebRequest.Request", request);

	if (activity.IsAllDataRequested)
	{
	activity.AddTag(SpanAttributeConstants.ComponentKey, "http");
	activity.AddTag(SpanAttributeConstants.HttpMethodKey, request.Method);
	activity.AddTag(SpanAttributeConstants.HttpHostKey, HttpTagHelper.GetHostTagValueFromRequestUri(request.RequestUri));
	activity.AddTag(SpanAttributeConstants.HttpUrlKey, request.RequestUri.OriginalString);
	activity.AddTag(SpanAttributeConstants.HttpFlavorKey, HttpTagHelper.GetFlavorTagValueFromProtocolVersion(request.ProtocolVersion));
	}
	}


		string dataSource = null;

		using (var activityListener = new ActivityListener

		public const string DatabaseStatementKey = "db.statement";
		public const string DatabaseStatementTypeKey = "db.statement_type";

Added instrumentation for netfx SqlClient. #761

Added instrumentation for netfx SqlClient. #761

Conversation

CodeBlanch commented Jul 2, 2020

Changes

Checklist

Choose a reason for hiding this comment

Choose a reason for hiding this comment

cijothomas commented Jul 2, 2020

cijothomas commented Jul 2, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

eddynaka Jul 2, 2020 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

vhatsura commented Jul 2, 2020

cijothomas commented Jul 2, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

cijothomas left a comment

Choose a reason for hiding this comment

codecov bot commented Jul 7, 2020 • edited Loading

Codecov Report

Choose a reason for hiding this comment

eddynaka Jul 2, 2020 •

edited

Loading

codecov bot commented Jul 7, 2020 •

edited

Loading